test(frontend): a wait begins at the thing it is evidence of - #1189
Conversation
`waitForRequest` was opened above the navigation, so its five second budget covered the page load and both fills as well as the click it exists to watch. The trace of the failing run spends it exactly there: the wait opens at +573549ms, the navigation alone takes 3.09s and the description fill starts at +578678ms, past the 5000ms mark, so the budget was gone before the submit was ever clicked. The 3000ms the spec holds `GET /users` for is not what spends it — that read is concurrent and the save does not wait on it, which is the whole point of the case. Opened at the submit, the budget covers the click and the request it makes. Refs #1173
Both specs prove the strip travels by polling until its scroll position differs from the one it opened at, which answers on the first frame of a smooth scroll, and then read the arrived node's offset from the middle exactly once. That reading is taken somewhere along the travel rather than at the end of it: the esports case failed in CI at 44px against a bound of 24. The bound is untouched and the claim is the same. Reproduced with the renderer throttled 8x, which is what starves the frames a smooth scroll advances on: 15 of 15 runs failed at 225-308px before, 0 of 15 after, and 0 of 15 at 12x. Refs #1173
|
Rebased onto main, which now carries #1190 — the same spec, fixed differently. That change kept the wait above the navigation and raised its budget to 60s; this one moves the wait to immediately before the submit and raises nothing. Resolved in favour of the narrower fix, because #1173's first criterion is that a spec which delays a route on purpose does not spend a default timeout on that delay, and a 60s budget still spends the wait on the page load and the two fills — it just leaves more room. The reason given for opening it early, that a save landing quickly would otherwise be missed, cannot happen: the save is caused by the click, so a wait opened immediately before that click cannot miss it. Measured rather than argued: 20 of 20 failed at slowMo 1200 with this fix reverted, 0 of 20 with it, and 0 of 20 again at slowMo 1800. The trace evidence for the timing is in the PR body. Happy to take the 60s back if there is a case for it I have not seen. |
355269a to
60e7592
Compare
1 participant
Why
Four end-to-end specs failed on a pull request that changes only Kotlin and touches no frontend
file. A red suite on an unrelated change teaches everybody to re-run rather than read the result,
which is the habit #1095 spent nine slices removing.
closes #1173
What this achieves
Two of the four are fixed, at their real causes. The other two are split out with their evidence
rather than guessed at: #1186 and #1187.
A third spec is fixed alongside, because it turned out to be the same defect as one of them.
How
The save's wait begins at the submit it is evidence of.
committee-save.spec.tsopened itswaitForRequestabove the navigation, so the 5000ms was spent on a page load, an edit click and aname fill before the submit it exists to observe was ever clicked. From the failing trace: the wait
opens at +573549,
gotoruns to +576643, the edit click to +578302, and the budget expires at+578549 during the description fill. The wait now opens immediately before the submit click, so its
budget covers the click and the request that click makes.
The line's landing is measured once it has landed.
esports-season-drag.motion.spec.tspolleduntil the strip's scroll differed from where it opened — which answers on the first frame of a
smooth scroll — and then read the arrived node's offset from centre exactly once. CI read 44 against
a bound of 24: the line was still travelling. It now polls the offset.
boards-swipe.motion.spec.tshad the identical shape and is fixed with it.
No timeout raised, no default changed, no bare wait added, and every assertion and bound is
unchanged.
Not in scope
The two that could not be reproduced, each filed with its trace evidence, what was ruled out, and an
unproven hypothesis recorded so the next reader does not derive it again: #1186 (a wheel that
scrolls nothing on mobile-chrome) and #1187 (one frame still moving after the reduced ceiling).
Worth a reviewer's attention
The issue's own diagnosis was wrong, and so was mine. #1173 supposed the 3000ms
GET /usersdelay ate the budget. It does not: the read is concurrent and the save never waits on it, which is
the point of the case — the test takes 520ms end to end with the delay at 3000 and 532ms with it at
0. And
boards-swipe.motion.spec.tsis the test #1148's own body wrote off as "the known starvationflake". It was this defect.
The reproduction knob had to match the mechanism, per #1141. For the save it is
launchOptions.slowMo, which lengthens the wall-clock between the wait opening and the requestwithout blowing any single step; CPU hogs did reproduce it, at 19 in 20, but also blew
page.gotosixteen times, which is not the CI symptom. For the two motion specs it is renderer CPU throttling
through
Emulation.setCPUThrottlingRate, since a smooth scroll advances on delivered frames.Criterion 1 generally. A
setTimeoutinside a route handler appears exactly once in the wholesuite, and that is this one. The other manufactured pauses are gesture cadence rather than held
routes, and none sits inside an inherited-budget wait.
Verification
committee-saveat slowMo 1200committee-saveat slowMo 1800esports-season-dragat 8x renderer throttleesports-season-dragat 12xboards-swipeat 8xFull
yarn test:e2e: exit 0, 822 passed, 0 failed, 36 skipped.yarn typecheckandyarn lintboth exit 0.
Diff breakdown —
█added░removed, scaled to the largest row.